Update messaging for measuring message delay between App and Hub #2499

juanscr · 2024-09-05T03:39:28Z

Description

This pull request has two purposes:

Fix the way the message request is timestamped by using a monotonic timer instead of the Date as it could be subject to user clock skew.
Add a mechanism for app developers to access Host to App message delay to analyze how much the message travel time impacts the latency of each function call or initialization.

For the second purpose, with this PR, an app developer can register a function that receives the message delays per function call as soon as a response is received from the host so they can log it or store it in their own telemetry. As app developers do not have information about the internal message IDs, the handler gets passed information about the callback that is resolving so they can approximately pinpoint which call had that message delay.

Note: it was decided to not expose message IDs as it is a really big architectural change in the codebase and the value of exposing them to app developers would be really small in comparison to the change.

Main changes in the PR:

Change the timestamp on all message requests from Date.now() to use performance.now() + performance.timeOrigin.
Add a function to register a handler that will be called each time a response is received from the host with information about the message delay.

Validation

Validation performed:

Ran all the unit tests and passed them successfully.
Execute the build and see that all test apps properly build.
Create a test app with a registered handler and log the values that were being received.

Unit Tests added:

Yes

End-to-end tests added:

No

Additional Requirements

Change file added:

Yes

Data

This is the response message delay for get context:

This is the request message delay for one-way traffic such as change theme: (this one shows more longer timestamps)

This is the request message delay for onw-way traffic fullScreenChanged:

packages/teams-js/src/public/app.ts

packages/teams-js/src/internal/interfaces.ts

packages/teams-js/src/internal/communication.ts

apps/teams-test-app/src/components/AppAPIs.tsx

packages/teams-js/src/internal/utils.ts

packages/teams-js/src/internal/telemetry.ts

packages/teams-js/src/internal/messageObjects.ts

packages/teams-js/test/utils.ts

ndangudubiyyam

Looks good to me

packages/teams-js/src/internal/handlers.ts

packages/teams-js/src/internal/communication.ts

packages/teams-js/src/internal/hostToAppTelemetry.ts

packages/teams-js/src/internal/communication.ts

maglims · 2024-10-23T18:52:55Z

Just FYI, I think @TrevorJoelHarris has checked in a code refactoring how communication works. You might have to rebase on that and make changes accordingly. @juanscr

juanscr · 2024-10-23T19:46:15Z

Just FYI, I think @TrevorJoelHarris has checked in a code refactoring how communication works. You might have to rebase on that and make changes accordingly. @juanscr

Yeah, I thought there was going to be an issue with Trevor's changes. But everything is still compliant with this PR, the sync is made tho. Later down the line when the sendMessageToParentAsync function gets removed some changes will need to be done but for now everything keeps working as usual 😄

With this new timestamped messaged, the host can properly compare and evaluate how much time the request got delayed to an issue on a busy event loop.

This new handler will allow any application developer to register a function for analyzing or storing performance metrics related to latencies due to a message delay sending the response back from the host to the app.

The old field will be preserved with backwards compatibility with previous versions that still consume this field.

All the telemetry related code is added to the telemetry module to avoid cluttering the communication layer with nuances about telemetry.

packages/teams-js/src/internal/utils.ts

packages/teams-js/src/internal/communication.ts

sumathin-lang · 2024-10-31T00:20:18Z

packages/teams-js/src/internal/communication.ts

  const targetWindow = Communication.parentWindow;
  const request = createMessageRequest(apiVersionTag, actionName, args);
+  HostToAppMessageDelayTelemetry.storeCallbackInformation(request.uuid, {
+    name: actionName,
+    calledAt: request.timestamp,


@juanscr isnt this "calledAt" supposed to be the monotonicTimestamp

Hey @sumathin-lang, not necessarily. This information is merely contextual around when the callback happened and isn't used for any calculation. I selected the date instead of the monotonicTimestamp as it should be more proper for a global timestamp as it does not possess issues as not ticking while sleeping and so forth (w3c/hr-time#115 (comment)). I can change it to monotonicTimestamp if you want but it's a minute detail.

@juanscr I would suggest using the same "units" for messageDelay and calledAt. Even if the App wants to use this "calledat" to measure some kind of delta, perf.now is a better choice compared to date,now. But i will let the teams-js team make this call

juanscr requested a review from a team as a code owner September 5, 2024 03:39

maglims reviewed Sep 9, 2024

View reviewed changes

packages/teams-js/src/public/app.ts Outdated Show resolved Hide resolved

packages/teams-js/src/internal/interfaces.ts Show resolved Hide resolved

packages/teams-js/src/internal/communication.ts Outdated Show resolved Hide resolved

erinha reviewed Sep 9, 2024

View reviewed changes

apps/teams-test-app/src/components/AppAPIs.tsx Outdated Show resolved Hide resolved

juanscr force-pushed the juancard/messageDelay branch 2 times, most recently from 61059e3 to fe1cd61 Compare September 11, 2024 00:41

sumathin-lang requested changes Sep 11, 2024

View reviewed changes

packages/teams-js/src/internal/messageObjects.ts Outdated Show resolved Hide resolved

packages/teams-js/src/internal/messageObjects.ts Outdated Show resolved Hide resolved

packages/teams-js/test/utils.ts Show resolved Hide resolved

juanscr force-pushed the juancard/messageDelay branch from 0ad25a2 to 114df12 Compare September 13, 2024 16:34

juanscr force-pushed the juancard/messageDelay branch from 7b23b3f to 2c4236f Compare September 23, 2024 14:05

juanscr force-pushed the juancard/messageDelay branch 2 times, most recently from 28f9abb to 3733b01 Compare October 9, 2024 20:53

ndangudubiyyam reviewed Oct 18, 2024

View reviewed changes

packages/teams-js/src/internal/handlers.ts Show resolved Hide resolved

ndangudubiyyam previously approved these changes Oct 18, 2024

View reviewed changes

juanscr dismissed ndangudubiyyam’s stale review via c987c5b October 22, 2024 15:32

juanscr force-pushed the juancard/messageDelay branch from 9ccaa4d to c987c5b Compare October 22, 2024 15:32

maglims reviewed Oct 22, 2024

View reviewed changes

packages/teams-js/src/internal/communication.ts Show resolved Hide resolved

packages/teams-js/src/internal/hostToAppTelemetry.ts Show resolved Hide resolved

packages/teams-js/src/internal/hostToAppTelemetry.ts Outdated Show resolved Hide resolved

maglims reviewed Oct 22, 2024

View reviewed changes

packages/teams-js/src/internal/hostToAppTelemetry.ts Outdated Show resolved Hide resolved

juanscr enabled auto-merge (squash) October 23, 2024 01:57

juanscr force-pushed the juancard/messageDelay branch from c987c5b to 2eca21a Compare October 23, 2024 01:57

maglims reviewed Oct 23, 2024

View reviewed changes

packages/teams-js/src/internal/communication.ts Outdated Show resolved Hide resolved

juanscr added 7 commits October 25, 2024 10:52

Add timestamp for each message request.

9868856

With this new timestamped messaged, the host can properly compare and evaluate how much time the request got delayed to an issue on a busy event loop.

Create handler for streaming performance metrics.

ec13472

This new handler will allow any application developer to register a function for analyzing or storing performance metrics related to latencies due to a message delay sending the response back from the host to the app.

Add changefile.

3a34290

Add new field with monotonic timestamp.

21cd299

The old field will be preserved with backwards compatibility with previous versions that still consume this field.

Organize telemetry in the correct module.

6894bed

All the telemetry related code is added to the telemetry module to avoid cluttering the communication layer with nuances about telemetry.

Delete messages after being handled.

c961f4d

Avoid circular import issue.

a2c905c

juanscr added 5 commits October 25, 2024 10:59

Fix callback id logging in hostToApp telemetry.

58bd878

Use standarized name for monotonic timestamp.

0ced08a

Log handled metrics.

95935f1

Use common ending time in telemetry.

8f30c51

Rewrite field for clarity.

410ede6

juanscr force-pushed the juancard/messageDelay branch from 602dfbc to 410ede6 Compare October 25, 2024 16:00

ndangudubiyyam previously approved these changes Oct 28, 2024

View reviewed changes

juanscr added 2 commits October 28, 2024 11:54

Merge branch 'main' into juancard/messageDelay

4615cc9

Merge branch 'main' into juancard/messageDelay

2fbfccb

maglims previously approved these changes Oct 29, 2024

View reviewed changes

juanscr added 2 commits October 29, 2024 18:15

Merge branch 'main' into juancard/messageDelay

cf8fdd9

Merge branch 'main' into juancard/messageDelay

9baa1bf

juanscr dismissed stale reviews from ndangudubiyyam and maglims via 9baa1bf October 29, 2024 23:21

ndangudubiyyam previously approved these changes Oct 29, 2024

View reviewed changes

maglims previously approved these changes Oct 30, 2024

View reviewed changes

juanscr requested a review from sumathin-lang October 30, 2024 01:23

sumathin-lang requested changes Oct 30, 2024

View reviewed changes

packages/teams-js/src/internal/utils.ts Outdated Show resolved Hide resolved

packages/teams-js/src/internal/communication.ts Show resolved Hide resolved

Do not mix up date and monotonic timers.

26698e7

juanscr dismissed stale reviews from maglims and ndangudubiyyam via 26698e7 October 30, 2024 23:33

juanscr requested a review from sumathin-lang October 30, 2024 23:35

sumathin-lang requested changes Oct 30, 2024

View reviewed changes

packages/teams-js/src/internal/communication.ts Show resolved Hide resolved

sumathin-lang requested changes Oct 31, 2024

View reviewed changes

ndangudubiyyam self-requested a review October 31, 2024 02:28

ndangudubiyyam approved these changes Oct 31, 2024

View reviewed changes

Merge branch 'main' into juancard/messageDelay

c8f4dba

sumathin-lang approved these changes Oct 31, 2024

View reviewed changes

juanscr merged commit 6eaa277 into main Oct 31, 2024
28 checks passed

juanscr deleted the juancard/messageDelay branch October 31, 2024 20:03

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Update messaging for measuring message delay between App and Hub #2499

Update messaging for measuring message delay between App and Hub #2499

juanscr commented Sep 5, 2024 •

edited

Loading

ndangudubiyyam left a comment

maglims commented Oct 23, 2024

juanscr commented Oct 23, 2024

sumathin-lang Oct 31, 2024 •

edited

Loading

juanscr Oct 31, 2024

sumathin-lang Oct 31, 2024

Update messaging for measuring message delay between App and Hub #2499

Update messaging for measuring message delay between App and Hub #2499

Conversation

juanscr commented Sep 5, 2024 • edited Loading

Description

Main changes in the PR:

Validation

Validation performed:

Unit Tests added:

End-to-end tests added:

Additional Requirements

Change file added:

Data

ndangudubiyyam left a comment

Choose a reason for hiding this comment

maglims commented Oct 23, 2024

juanscr commented Oct 23, 2024

sumathin-lang Oct 31, 2024 • edited Loading

Choose a reason for hiding this comment

juanscr Oct 31, 2024

Choose a reason for hiding this comment

sumathin-lang Oct 31, 2024

Choose a reason for hiding this comment

juanscr commented Sep 5, 2024 •

edited

Loading

sumathin-lang Oct 31, 2024 •

edited

Loading